Skip to content

fix(events): repair torn outbox lines and report the ones that cannot be read - #900

Merged
laynepenney merged 1 commit into
devfrom
fix/events-torn-line-and-count
Aug 20, 2026
Merged

fix(events): repair torn outbox lines and report the ones that cannot be read#900
laynepenney merged 1 commit into
devfrom
fix/events-torn-line-and-count

Conversation

@laynepenney

Copy link
Copy Markdown
Member

What

Fix 4 of the torn-line sweep, on the event outbox. Two parts, and they are separate claims.

Terminator repair. emit() appended in text mode and wrote json + "\n". A previous write that died between write() and fsync() leaves a last line with no terminator, so the next append glues two records into one line. The damage runs FORWARD from the tear: the torn record and the next healthy append fuse into one unparseable line, while the record before the tear is untouched. So a torn write does not cost one event, it costs that record and the next one written after it — permanently, because every later append builds on the glued line. What the repair buys is precise and worth stating exactly: it cannot recover a record that was never fully written, and it saves the next one. Without it you lose two; with it you lose the one the crash truncated. emit() now probes the last byte under the existing write lock and heals the seam before writing.

The count. Both readers skipped unusable lines in silence. For the channel bridge an unreadable line is a message that never reaches a channel. It is reported on every read, not once: the cursor filter applies only to lines that parse, so a line with no usable seq can never be advanced past, wherever it sits in the file — position is irrelevant, and mid-file lines repeat exactly as trailing ones do. That is deliberate rather than incidental — the line is still there and still unreadable — and how long it stays that way depends on which kind of tear produced it, a distinction the word "torn" hides:

tear after the next emit()
unterminated — the record is complete, only its "\n" was lost recovers fully. Seam repair ends the line and it parses. Zero malformed.
truncated — the write stopped mid-record never recovers. The seam is healed so the following append is no longer glued on, but the record's bytes were never written and nothing reconstructs them.

So only a truncated record is permanently unreadable, and an outbox carrying one reports it on every read until someone repairs the file. Listed as a residual below. Both rows are pinned by witnesses, and they are each other's control. read_events_detailed() returns the events and the lines it could not read, from the same read — a second pass would describe a different moment, and the outbox is appended to concurrently. read_events() stays list-shaped for the eleven call sites that index and len() it — all of them tests, and zero production callers remain once the bridge moves to read_events_detailed(), so the wrapper is a test-compatibility surface rather than a load-bearing API. An earlier version of this description said seventeen; that was an artifact of a substring query counting a def, two prose mentions inside strings, and four hits on an unrelated _read_events helper in another test file. The bridge reports on stderr so stdout stays parseable.

The count is reported from the read path only. _current_seq() runs once per emit inside the write lock, where a count would be per-append and aimed at whoever happened to be writing. Its docstring states that, because an omission and a decision look identical in code.

Also guarded, each with its own witness:

  • the decode moved to bytes-per-line, so a single invalid byte can no longer escape as UnicodeDecodeError from outside every guard;
  • the parse guard's exception tuple is now derived from what json.loads can raise rather than from what had been seen: ValueError (the base class of JSONDecodeError) and RecursionError, which is not a ValueError, so deep nesting used to escape the old (JSONDecodeError, TypeError) pair. Structure is checked separately, since a valid JSON array parses and is still not an event;
  • seq values are type-validated: bool is an int subclass, and a float becomes inf and serializes as Infinity, which is not valid JSON;
  • a corrupt cursor no longer bricks reads.

Three things this fix got wrong first

None of them were found by its own witnesses, which is the part worth recording.

An early version swallowed OSError in the line iterator. That is precisely the OSError-to-zero fallback an earlier fix removed on purpose: swallow it and _current_seq() returns 0, and emit() then allocates sequence numbers that duplicate live ones. A pre-existing test stood guard over that contract and caught it. Content errors are data and get skipped-and-counted; an I/O error is not knowing what the file holds and must fail closed. The reader tolerates FileNotFoundError only — rotation renames the file — and propagates every other OSError, because a reader that swallows EIO reports "no new events" forever.

MalformedLine and EventRead were dataclasses. This module is loaded out-of-tree by spawned workers via spec_from_file_location() + exec_module(), which does not register it in sys.modules, and @dataclass resolves field types through exactly that. Every worker died at import, and the symptom was a concurrency test timing out with "neither writer reached sequence allocation" — a failure that reads like flakiness. Now plain classes, with the constraint written into the file and a witness that fails in 0.06 s naming the AttributeError instead of after a 10 s timeout.

The default report echoed raw line content to stderr, verbatim, including an API-key-shaped string in a measured probe. stderr is copied into CI logs, scrollback, and pasted transcripts. Redacting was rejected: matching secret-shaped patterns in arbitrary bytes is a denylist over untrusted input, the same defect shape the parse guard exists to avoid. The excerpt stays on the data object for callers that need it; the default report prints ordinal and reason, both structural, with show_content=True as an opt-in.

One existing test's monkeypatch target moved from read_text to read_bytes because the read verb changed. Its contract and every assertion are unchanged; without the move it would have gone green by missing its target rather than by the behaviour holding. Both it and the new witness now undo the patch before reading the file back, since a verification must not travel the path the test deliberately sabotaged.

Two statements in an earlier version of this description were wrong, and a reviewer measured both: the glue direction was stated backwards, and the unreadable-line count was claimed to be reported once. The whole suite was green while the prose contradicted the measured behaviour — the prose and the code comments agreed with each other, which is why nothing looked wrong; what neither matched was what the code did. Nothing pinned it. Three witnesses now do, including the mid-file case, which shows the rule is broader than the trailing-line framing that surfaced it.

Correcting this description and the commit message was not enough, and a second review caught that: the same backwards claim was still in the production repair comment and the test module docstring. Fixing the cited surfaces and stopping there left the code asserting one direction while this description asserted the other — an artifact contradicting itself, which is worse than being uniformly wrong. Running a query for the whole class rather than the cited instances then found a third live instance neither review named: the reported-once claim, still standing in that same docstring. All are corrected, the class query comes back clear, and the executable syntax tree is unchanged by those edits.

A sixth review found three more, and all three were prose — the code it gated was clean. The one worth the round: the reported-once claim was still live in the channel-bridge comment, in the bridge hunk of all five versions, and every class query I ran missed it because it paraphrases the sentence the earlier reviews cited rather than repeating it. A query built from a cited instance finds copies, not paraphrases; the class is the claim, and the only instrument that finds a paraphrase is reading the hunk. The other two are the two corrections above — the parse-guard framing, and the call-site count, which both reviewers had co-signed at v1 from that same substring query, so it needed re-deriving rather than re-reading. Sweeping the count as a class then turned up three further copies in docstrings that no review had cited.

A seventh review found two more, both measured, and one of them corrected a claim in the production code rather than in this text. F4: the replacement bridge comment said an unterminated record is reported and then heals at the next emit(). Measured false. An unterminated record whose bytes are complete is never reported at all — _iter_outbox() splits on b"\n", so a complete final chunk parses on the spot, before any emit, repair or no repair. The sentence implied a window of unreadability that does not exist. It is recut, and the gap that let it survive is now pinned: every tear fixture in this file emitted after tearing, so nothing had ever asked what the reader alone does with a torn file. W11 is that pair — the unterminated case reporting nothing across two reads, and the truncated case reporting one as its discriminating control. The reviewer's probe is the witness; I took it rather than restating it. The phrase's two siblings, the W10 header and the table above, are scoped to tear -> emit -> read and are true there, so they are deliberately unchanged.

F5: the suite totals were stale, corrected above. The mechanism is worth stating because the reviewer's diagnosis and my measurement differ: the +3 is not the #899 merge — that added 21 tests, and every one of them is inside both baselines — it is gr2/gr2_overlay/tests/, which the narrower invocation does not collect. Both figures were correct measurements of different scopes; the defect was publishing one without naming which. Chasing it down is what surfaced the three stale mutation rows, which had gone out of date the same way and which no review had asked about.

Evidence (RAN)

  • 37 witnesses, none before. Terminator repair including a second tear and a fresh-file case; undecodable bytes; eight hostile-but-valid content rows; the I/O-versus-content boundary with a discriminating control; the count reaching a consumer, with a negative case; the out-of-tree loader constraint; three pinning how long an unreadable line keeps being reported and which record the glue destroys; and three for the truncated tear, added after a reviewer found a claim that a torn line self-heals at the next emit — TRUE of an unterminated record and FALSE of a truncated one, which is the whole problem with the bare word. That prose was wrong because every tear fixture until then dropped the trailing newline while leaving the record complete — the lucky case, and the only one I had ever tested. The realistic tear truncates the record mid-JSON, and the new witnesses carry a discriminating control — the unterminated tear, which DOES fully recover — so the finding is not mistaken for the norm. That control then caught the overcorrection: a later draft of this description swung to "a torn record never becomes readable," which the control disproves. The word "torn" covers two cases with opposite outcomes; this text now names them separately and never uses the bare word to make a claim about recovery. W11 is a later pair, reading a torn file with NO intervening emit, and it pins the sharper fact a seventh review measured: an unterminated record is never reported in the first place — not that it recovers — with the truncated case as its discriminating control.
  • Nine mutation rows, re-measured for this version over the two events spec files (71 tests) — the scope is stated because omitting it is exactly what made three of them wrong: text-mode decode → real UnicodeDecodeError (11); the old exception denylist → real RecursionError (1); terminator repair removed → 5; seq validation removed → TypeError (4); count silenced → 19; reporter silenced → exactly 1, which is the discrimination proving the count reaches a consumer rather than sitting in a field; OSError swallowed → 3; FileNotFoundError widened to OSError → 1; cursor guard removed → real TypeError (1). Restores hash-verified after every row, with the unmutated pair re-run as a control. Three of these rows were stale in v7 — published as 8, 3 and 12 where the true figures are 11, 5 and 19. They were measured early and never re-derived while five review rounds added witnesses to the very files they count. The code never changed; the evidence describing it went out of date silently, which is the same defect as a stale suite total and is invisible to every check in this PR except re-running it.
  • Full suite at both scopes, base pinned by SHA — omitting the scope is what made v7's totals unverifiable. On origin/dev@936756770e5520d222dfbbe1a34f366094c28f0d in an isolated worktree: pytest gr2/tests 1032 passed / 5 failed, pytest gr2 1035 / 5. On this head: 1069 / 5 and 1072 / 5. Delta exactly +37 in both scopes, matching the 37 witnesses, failure sets identical in both directions. The two scopes differ by gr2/gr2_overlay/tests/test_overlay_refs_namespace.py — 3 tests, measured passing on both sides, which pytest gr2/tests does not collect. v7 published 1067 / 1032: right for the narrow scope, and unverifiable to anyone running the wider one.
  • Every claim this description makes about behaviour is pinned by a named witness — 18 audited, 0 unpinned: the seventeen from v7 re-checked, plus the new an unterminated record is never reported claim, pinned by W11. Stated with its limit, because the check is weaker than it sounds: it verifies that a witness with the matching name exists and passes, not that the witness asserts exactly the sentence above it. It narrows the gap between prose and behaviour; it does not close it. Seven separate reviews found wrong behavioural claims in earlier versions of this text, every one of them surviving a green suite, so the audit exists because that class of defect is invisible to every other check here.
  • Lint unchanged everywhere, each measured in place with a swap-confirmed control: production files 6 = 6, the edited test file 23 = 23, the new file 0.

Residuals

Named rather than presented as clean:

  • These primitives now exist in three places. Consolidating them is outside this fix's scope: this file is production and the other copies are prototypes, so the dependency would run the wrong way.
  • The same content-echo property exists in the prototype reporter merged earlier and is not addressed here.
  • Unbounded line length remains a read-layer resource limit and is deliberately undefended.
  • A truncated record — an unterminated one is readable throughout and never reaches the report at all — is unreadable permanently: no later emit() repairs it, because the repair heals the seam and not the record, so every read reports it and a consumer polling in a loop warns every cycle until someone repairs the file. Suppressing that would need persisted already-reported state and would hide a re-occurring fault; reporting it is the lesser cost, but on a damaged outbox it is a standing cost, not a transient one.

Premium boundary: grip is OSS; this is local file mechanics over opaque paths and carries no identity, org, or policy content.

Fix 4 of the torn-line sweep, and the two-part contract it was ruled as.

TERMINATOR REPAIR. emit() appended with "a" and wrote json + "\n". A previous
write that died between write() and fsync() leaves a last line with no
terminator, so the next append GLUES two records into one. The damage runs
FORWARD from the tear: the torn record and THE NEXT HEALTHY APPEND fuse into
one unparseable line, while the record before the tear is untouched. A torn
write therefore costs that record and the next one written after it,
permanently, because every later append builds on the glued line. emit() now probes the
last byte under the existing write lock and heals the seam first.

THE COUNT. Both readers skipped unusable lines in silence. For the channel
bridge an unreadable line is a message that never reaches a channel. It is
reported on EVERY read, not once: the cursor filter applies only to lines that
parse, so a line with no usable seq can never be advanced past, wherever it
sits -- position is irrelevant and mid-file lines repeat exactly as trailing
ones do. Deliberate, not incidental, and its cost is named in the residuals.
read_events_detailed() now returns the events AND the lines it could not read,
from the SAME read. read_events() stays list-shaped for the ELEVEN call sites
that index and len() it -- all tests, and ZERO production callers remain once
the bridge moves to read_events_detailed(), so the wrapper is a
test-compatibility surface rather than a load-bearing API. An earlier draft of
this message said seventeen; that was a substring artifact counting a def, two
prose mentions inside strings, and four hits on an unrelated _read_events helper
in another test file. The bridge reports on stderr so stdout stays parseable.

Reported from the read path ONLY. _current_seq() runs once per emit inside the
write lock, where a count would be per-APPEND and aimed at whoever happened to
be writing. Its docstring says so, because an omission and a decision look
identical in code.

Also guarded, each with witnesses: the decode moved to bytes-per-line so a
single invalid byte cannot escape from outside every guard; the parse
guard's exception tuple is now derived from what json.loads can
raise rather than from what had been seen -- the old (JSONDecodeError,
TypeError) caught syntax errors but missed RecursionError, which is not a
ValueError, so deep nesting escaped; structure is checked separately, since a
valid JSON array parses and is still not an event; seq values are type-validated, since
bool is an int subclass and a float becomes inf and serializes as Infinity;
and a corrupt cursor no longer bricks reads.

THREE THINGS THIS FIX GOT WRONG FIRST, none found by its own witnesses:

- An early version swallowed OSError in the line iterator. That is exactly the
  OSError-to-zero fallback an earlier fix removed on purpose: swallow it and
  _current_seq returns 0, then emit allocates sequence numbers that duplicate
  live ones. A pre-existing test stood guard and caught it. Content errors are
  data and get skipped-and-counted; an I/O error is not knowing what the file
  holds and must fail closed. The reader tolerates FileNotFoundError only,
  because rotation renames the file, and propagates every other OSError.
- MalformedLine and EventRead were dataclasses. This module is loaded
  out-of-tree by spawned workers via spec_from_file_location + exec_module,
  which does not register it in sys.modules, and dataclass resolves field types
  through exactly that. Every worker died at import. Now plain classes, with a
  witness that fails in 0.06s naming the cause instead of after a 10s timeout
  that reads like flakiness.
- The default report echoed raw line content to stderr, verbatim, including an
  API-key-shaped string in a measured probe. stderr is copied into CI logs and
  transcripts. Redacting was rejected: matching secret-shaped patterns in
  arbitrary bytes is a denylist over untrusted input, the same defect the parse
  guard exists to avoid. The excerpt stays on the data object; the default
  report prints ordinal and reason, both structural, with show_content opt-in.

One existing test's monkeypatch target moved read_text -> read_bytes because
the read verb changed; its contract and every assertion are unchanged, and it
would otherwise have gone green by missing its target. Both it and the new
witness now undo the patch before reading the file back, since a verification
must not travel the path the test deliberately sabotaged.

A reviewer measured both of those statements against an earlier version of
this message and of the description, where the glue direction was backwards
and the count was claimed to be reported once. The suite was green while the
prose said the opposite of the code, because nothing pinned that behavior.
Three witnesses now do, including the mid-file case, which shows the rule is
broader than the trailing-line framing that surfaced it.

A third review then caught a further claim, in the description only: that a
torn last line self-heals at the next emit. That is true of one tear and false
of the other, and the bare word "torn" hides the difference. An UNTERMINATED
record -- complete, only its newline lost -- DOES recover fully once the seam is
healed. A TRUNCATED record -- the write stopped mid-record -- never does: its
bytes were never written, so it stays unreadable and every read reports it until
the file is repaired. A FOURTH review then caught the opposite
overcorrection, which a later draft of this message had made -- claiming a torn
record never becomes readable -- and the unterminated-tear control disproves it. Both cases are now named separately and the bare
word is not used to claim anything about recovery. That prose was wrong only
because every tear fixture until then dropped the trailing newline and left the
record COMPLETE -- the lucky case. Three witnesses now cover the realistic tear,
with the UNTERMINATED tear kept as a discriminating control so the finding cannot be
mistaken for the norm. What the repair buys, stated exactly: it cannot recover a
record that was never fully written, and it saves the NEXT one.

Correcting the message and the description was not enough, and a second review
caught that: the same backwards claim was still in the production repair
comment and in the test module docstring. Fixing the two cited surfaces and
stopping there left the code asserting one direction while the description
asserted the other -- an artifact contradicting itself, which is worse than
being uniformly wrong. A sweep for the whole class rather than the cited
instances found a third live instance neither review named: the
reported-once claim, still standing in that same docstring. Those particular
corrections changed comments only and left the executable syntax tree identical,
verified by parsing both revisions and comparing with docstrings stripped.

A FIFTH review then caught the same overclaim surviving in the test module
comment -- "A TORN RECORD IS NEVER REPAIRED BY A LATER EMIT" -- which the
unterminated control disproves. The class query that was supposed to have swept
it missed it because the query was CASE-SENSITIVE and the comment is upper case:
a false negative from my own instrument, of the kind noted one revision earlier
and then committed in the next query. That round also renamed the control from
"benign" to "unterminated" so the tests and the prose use one vocabulary, so
unlike the previous round the syntax tree DID change here and the suite was
re-run rather than reasoned about.

A SIXTH review, from the other reviewer, found three defects and all three
were PROSE -- the code it gated was clean. The first is the one worth the round:
the reported-once claim was still live in the channel-bridge comment, in the
bridge hunk of ALL FIVE versions, and every class sweep I ran missed it because
it PARAPHRASES the sentence the earlier reviews cited rather than repeating it.
A query built from a cited instance finds COPIES, not paraphrases; the class is
the CLAIM, and the only instrument that finds a paraphrase is reading the hunk.
The second: the parse-guard sentence read as if the new tuple were open-ended.
It is enumerated -- (ValueError, RecursionError). What changed is where the
enumeration comes FROM: what json.loads can raise, rather than what had been
seen. The third: "seventeen call sites" was an artifact of a substring query
that counted a def, two prose mentions inside strings, and four hits on an
unrelated _read_events helper in another test file. The real count is eleven,
all tests, zero production callers. BOTH reviewers co-signed seventeen at v1
from that same defective query, which is why it needed re-deriving rather than
re-reading -- and the class sweep for it then found three more copies of the
count in docstrings that no review had cited.

A SEVENTH review found two more, and one of them was wrong in the CODE rather
than in the prose about it. The bridge comment said an unterminated record is
reported and then heals at the next emit. Measured false: an unterminated record
whose bytes are COMPLETE is never reported at all, because _iter_outbox() splits
on b"\n" and a complete final chunk parses on the spot -- before any emit, repair
or no repair. The sentence implied a window of unreadability that does not exist.
The gap that let it survive is now pinned: every tear fixture in this file emitted
AFTER tearing, so nothing had ever asked what the READER alone does with a torn
file. W11 is that pair -- the unterminated case reporting nothing across two
reads, the truncated case reporting one as its discriminating control. The
reviewer's own probe became the witness. Its two siblings, the W10 header and the
description's table, are scoped to tear -> emit -> read and are true there, so
they are deliberately unchanged.

The second finding was stale suite totals, and the mechanism differs from the
one proposed: the +3 is not the earlier merge, which added 21 tests that are
inside both baselines, but a test directory the narrow invocation does not
collect. Both figures were correct measurements of different scopes and the
defect was publishing one without naming which -- which is also how the three
mutation rows above went stale, unasked about by any review.

RESIDUALS, named rather than presented as clean: this is a third copy of these
primitives, and consolidating them is outside this fix's scope; the same
content-echo property exists in the prototype reporter merged earlier;
unbounded line length remains a read-layer resource limit and is undefended;
and a TRUNCATED record -- an UNTERMINATED one is readable throughout and never
reaches the report at all -- is permanently unreadable and reported on every read, so a consumer
polling in a loop warns every cycle until the file is repaired -- suppressing
that would need persisted already-reported state and would hide a re-occurring
fault, so it is the lesser cost but it is a cost.

Evidence: 37 witnesses, 0 before. Nine mutation rows, RE-MEASURED for this
version over the two events spec files (71 tests), each killing witnesses whose
failure TYPE matches the mutation, restores hash-verified with the unmutated
pair as a control: decode 11, exception tuple 1, terminator repair 5, seq
validation 4, count silenced 19, reporter silenced 1, OSError swallowed 3,
FileNotFoundError widened 1, cursor guard 1. Three of those rows were STALE --
published as 8, 3 and 12 where the true figures are 11, 5 and 19 -- because
they were measured early and never re-derived while five review rounds added
witnesses to the files they count.

Full suite at BOTH scopes, base pinned by SHA, since omitting the scope is what
made the last version's totals unverifiable. On origin/dev@93675677 in an
isolated worktree: pytest gr2/tests 1032 passed / 5 failed, pytest gr2 1035 / 5.
On this head: 1069 / 5 and 1072 / 5. Delta exactly +37 in both, matching the
witness count, failure sets identical in both directions. The scopes differ by
gr2/gr2_overlay/tests/test_overlay_refs_namespace.py -- 3 tests, measured
passing on both sides, which the narrow invocation does not collect. Lint
unchanged: production 6 = 6, edited test file 23 = 23, new file 0.

Premium boundary: grip is OSS; this is local file mechanics over opaque paths
and carries no identity, org, or policy content.

Co-Authored-By: Claude <noreply@anthropic.com>
@laynepenney

Copy link
Copy Markdown
Member Author

Pre-push ratification record

Both verdicts were given on the frozen artifacts before this branch existed on the remote, and both are bound to head 69e92679c749cd6e80b6827b59c5cce2995a14a6 — the exact SHA pushed here, confirmed by ls-remote.

Four artifacts were frozen and independently re-derived by both reviewers:

artifact hash
range.patch (RAW) bd26b74b4c5934faf022f1ca69eb891945bc08acb586240215382ab886d5f8c2
metadata.fuller.txt (RAW) 0abe957fb95936507efc6658921eafdf728c4929448cd5059579c1ea37d10f14
PR title (NORM) f49971a5434e73f54f6258def345792cb48c611498ce09e425d2edf94467b5c2
PR body (NORM) 6c2fafe5a76643fa5de130a0a025e8f4cd6d76719513af304cd7c47b5d538e8f

The title and body above were published from those exact frozen files and read back from the live PR; both NORM hashes match.

Stromus — APPROVE (RAN). Reproduced the tree at fec92e04, both suite scopes matching the published figures (1072/5 broad, 1069/5 narrow) with identical known-failure sets, and independently reproduced the corrected terminator-repair mutation row at exactly 5 heal-dependent kills. Noted that W11 survives that mutation, which is the finding's own physics confirmed for free: seam repair is irrelevant to a record that was already readable.

Sentinel — APPROVE (RAN). Re-derived all four hashes, applied the frozen range onto isolated dev@9367567, and ran the two events specs with the import resolving into the checkout rather than machine-wide site-packages — the direct-interpreter control resolved stale site-packages, the harness mapping resolved the checkout. 71 passed. Mutation: dropping the final split chunk made the W11 complete-unterminated witness lose its second record and made the truncated control suppress its report; both halves red. Restore diff-clean, suite back to 71. Scope covered code, tests, commit metadata, title, body, and branch name.

This artifact went through nine frozen versions. Seven review rounds found wrong claims in its prose, every one of them surviving a green suite — which is why the description carries its own correction history rather than presenting a clean face.

@laynepenney
laynepenney merged commit 1dd7474 into dev Aug 20, 2026
1 check passed
@laynepenney
laynepenney deleted the fix/events-torn-line-and-count branch August 20, 2026 18:10
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant